[小ネタ] JMeterの定数タイマの適用対象でハマった話

はじめに

清水です。先日負荷テストツールのJMeterを使う機会がありました。前々から名称は聞いたことが効いたことがあったものの使ったのは初めてだったのですが、すごく多機能で便利だなーと思いました。

今回のエントリではこのJMeter使用時にちょっとひっかかった、定数タイマが適用される対象についてまとめてみたいと思います。

具体的には、以下のようなテスト計画があったとします。

このとき「定数タイマ」は「HTTPリクエストfile1.html」と「HTTPリクエストfile2.html」の双方の実行前に適用されます。 つまり、ループコントローラによるループ1回の処理は以下となります。

• 定数タイマによる処理待ち
• HTTPリクエストfile1.html
• 定数タイマによる処理待ち
• HTTPリクエストfile2.html

ループコントローラ処理前に実行されるのでは？という勘違い

はい、すでに本エントリで得られる正しい結論は先ほど「はじめに」にて述べてしまったのですが、私が勘違いしていたことをまとめみます。

スレッドグループでは上から順に各要素が処理される、と考えていたので、上記のテストシナリオでは、例えばループコントローラによるループを2回として、

• 定数タイマにより処理待ち
• HTTPリクエストfile1.html
• HTTPリクエストfile2.html
• HTTPリクエストfile1.html
• HTTPリクエストfile2.html

となると考えていました。つまりループコントローラの処理が始まる前に定数タイマによる処理待ちが入る、と。 しかし実際にこのテストシナリオで負荷テストを実行してみると、なにか想定しているシナリオと違う挙動になり、確認してみることにしました。

アクセスログから実際の処理を確認

実際にはどのようにシナリオが処理されているのか、アクセスログログを確認してみました。

上記のスクリーンショットのシナリオで、定数タイマを3000ミリ秒（＝3秒）、ループコントローラのループ回数を2回、スレッドグループはスレッド数を1、ループ回数を1回とした処理が下記です。（HTTPサーバにはApacheを使用しています。またアクセス元IPアドレスはマスクしています。）

X.X.X.X - - [30/Apr/2017:07:05:22 +0000] "GET /file1.html HTTP/1.1" 200 6 "-" "Apache-HttpClient/4.5.2 (Java/1.8.0_131)"
X.X.X.X - - [30/Apr/2017:07:05:25 +0000] "GET /file2.html HTTP/1.1" 200 6 "-" "Apache-HttpClient/4.5.2 (Java/1.8.0_131)"
X.X.X.X - - [30/Apr/2017:07:05:28 +0000] "GET /file1.html HTTP/1.1" 200 6 "-" "Apache-HttpClient/4.5.2 (Java/1.8.0_131)"
X.X.X.X - - [30/Apr/2017:07:05:31 +0000] "GET /file2.html HTTP/1.1" 200 6 "-" "Apache-HttpClient/4.5.2 (Java/1.8.0_131)"

file1.htmlとfile2.htmlのアクセスの間隔が3秒（以上）あいていること、またfile2.htmlとfile1.htmlのアクセス間隔（つまりループコントローラ処理のあいだ）も3秒（以上）あいています。 つまり、冒頭で述べたとおり、各HTTPリクエストの処理に定数タイマが適用されることとなりました。

まとめ

負荷テストツールJMeterにて、定数タイマの適用対象がループコントローラ内の各HTTPリクエストだった、ということをまとめてみました。

きちんと仕様など把握していれば勘違いすることはないのかもしれませんが、とりあえず動かしてみるという場合では、その結果をきちんと確認してみること（今回ならアクセスログをみてみる）が大事だなと感じました。